<!--

    Licensed to the Apache Software Foundation (ASF) under one
    or more contributor license agreements.  See the NOTICE file
    distributed with this work for additional information
    regarding copyright ownership.  The ASF licenses this file
    to you under the Apache License, Version 2.0 (the
    "License"); you may not use this file except in compliance
    with the License.  You may obtain a copy of the License at

      http://www.apache.org/licenses/LICENSE-2.0

    Unless required by applicable law or agreed to in writing,
    software distributed under the License is distributed on an
    "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
    KIND, either express or implied.  See the License for the
    specific language governing permissions and limitations
    under the License.

-->
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN">

<html>
    <head>
        <title>Logging in NetBeans</title>
    </head>
    <body>

    <center>
        <h1>Logging in NetBeans</h1>
    </center>

    <p>
    The logging system in NetBeans is based on the standard
    JDK's <a href="@JDK@/java/util/logging/package-summary.html">java.util.logging</a>
    and complies to it as much as possible. This document
    sumarizes the basic usecases and shall be treated as a guide for
    writing good NetBeans ready logging code. The
    info given here is valid for default configuration of the logger as
    it is used in NetBeans. However it is possible to fully replace
    the system by providing own logging properties as
    in any
    <a href="@JDK@/java/util/logging/LogManager.html">other JDK application</a>.
    Then of course the behaviour may get completely
    different.
    </p>

    <p>
    Rather than printing raw exceptions to the console
    or implementing custom debug or logging facililities, code may
    use the <a href="@JDK@/java/util/logging/Logger.html">Logger</a> 
    to access logging in a higher-level
    fashion. This way the logging messages can be dynamically turned
    on and off by single switch on command line or even during runtime.
    </p>
    
    <p>Another important thing is to chain stack traces to
    exceptions using 
    <a href="@JDK@/java/lang/Throwable.html#initCause-java.lang.Throwable-">
    Throwable.initCause(Throwable)</a>, permitting you to throw an exception 
    of a type permitted by your
    API signature while safely encapsulating the root cause of the problem (in terms
    of other nested exceptions). Code should use 
    <a href="@JDK@/java/util/logging/Logger.html#log-java.util.logging.Level-java.lang.String-java.lang.Throwable-">
    Logger.log(Level.SEVERE, msg, exception)</a>
    rather than directly printing caught exceptions,
    to make sure nested annotations are not lost and to allow pluged in
    handlers of logging to process the exceptions.
    </p>
        

    <!--
    <p>Also localized messages may be annotated 
    to exceptions so that code which can deal
    with a caught exception with a user-visible UI can display a 
    polite and helpful message.
    Messages with no localized annotation can be handled in 
    a default way while the details
    are reserved for the log file.
    </p>
    -->
    
    <p>
    It is possible to use 
    <a href="@JDK@/java/util/logging/Logger.html#global">
        global logger
    </a>
    but it is preferred to create
    <a href="@JDK@/java/util/logging/Logger.html#getLogger-java.lang.String-">
        named and shared instances 
    </a> of loggers.
    The later has the advantage of finer control of what is going
    to be logged or not, as each named instance can be turned on/off 
    individually by using a command line property.
    </p>
    
<h3>Turning Logging On and Off</h3>    
    <p>
    As the logging system is completely JDK based, one can use the 
    traditional properties of 
    <a href="@JDK@/java/util/logging/LogManager.html">LogManager</a>
    and customize logging completely by themselves.
    </p>
    
    <p>
    However there is a simpler way how to enable logging of an named logger.
    Just start NetBeans with <code>-J-Dname.of.the.Logger.<b>level</b>=100</code>
    or any other number and all the log 
    <a href="@JDK@/java/util/logging/Level.html">Level</a>s 
    with higher or equal value will immediatelly
    be enabled and handled by the system.
    </p>

    <p>
    It is possible to turn the logging dynamically when the application
    is running. It is enough to just:<pre>
System.setProperty("name.of.the.Logger.<b>level</b>", "100");
LogManager.getLogManager().readConfiguration();
</pre>
    and logging state for the <q>name.of.the.Logger</q> is changed. The
    first line in the above code snippet changes the global properties and
    the second one asks the system to refresh the configuration of all
    loggers in the system.
    </p>

    <p>
    Of course this only works if the default NetBeans logger is in place.
    Sometimes however it may make sence to provide completely different logger.
    This can be done by one of two JDK standard properties:
    <code>java.util.logging.config.file</code> or
    <code>java.util.logging.config.class</code> as described at
    <a href="@JDK@/java/util/logging/LogManager.html">LogManager's javadoc</a>.
    If these properties are provide during the startup of the system,
    then the logging is fully dedicated to the configured custom loggers
    and of course no NetBeans standard configuration properties work.
    </p>

<h3>How to Write Logging Friendly Code</h3>


<h5>Handling Exceptions</h5>

<p>
To handle an exception and sent it to the log file (and possibly
show blinking
icon to the user in bottom right corner of main window):
</p>
<pre>
private static final <a href="@JDK@/java/util/logging/Logger.html">Logger</a> logger = <a href="@JDK@/java/util/logging/Logger.html#getLogger-java.lang.String-">Logger.getLogger</a>(ThisClass.class.getName());
try {
    foo.doSomething();
} catch (IOException ioe) {
    <a href="@JDK@/java/util/logging/Logger.html#log-java.util.logging.Level-java.lang.String-java.lang.Throwable-">logger.log</a>(Level.SEVERE, null, ioe);
}
</pre>

<p>
    <code>WARNING</code> behaves the same way by default.
</p>

<p>If the exception is not important, and by default shall not
be shown or logged at all one can
use the <code>Level.FINE</code>, <code>Level.FINER</code> or
<code>Level.FINEST</code>:</p>
<pre>
try {
    foo.doSomething();
} catch (IOException ioe) {
    logger.log(Level.FINE, "msg", ioe);
}
</pre>
<p>
The easiest way to make sure an exception is reported to the user is to 
use the 
<a href="@org-openide-dialogs@/org/openide/DialogDisplayer.html">dialog API</a>
with a code like this:
</p>
<pre>
try {
  // some operations
} catch (Exception ex) {
  <a href="@org-openide-dialogs@/org/openide/NotifyDescriptor.Exception.html">NotifyDescriptor.Exception</a> e = new NotifyDescriptor.Exception(ex);
  <a href="@org-openide-dialogs@/org/openide/DialogDisplayer.html">DialogDisplayer</a>.getDefault().notifyLater(e);
}
</pre>
<p>
This code will present a dialog box with warning message extracted from
the exception <code>ex</code> sometime in the <q>future</q> - e.g. when the
AWT event queue is empty and can show the dialog. Use of
<a href="@org-openide-dialogs@/org/openide/DialogDisplayer.html#notifyLater-org.openide.NotifyDescriptor-">
notifyLater</a> 
to plain
<a href="@org-openide-dialogs@/org/openide/DialogDisplayer.html#notify-org.openide.NotifyDescriptor-">
notify</a> 

is recommended in order to prevent deadlocks and
starvations
</p>

<h5>Retain nested stacktraces / change exception type</h5>
    
<p>
    To rethrow an exception use standard JDK's 
    <a href="@JDK@/java/lang/Throwable.html#initCause-java.lang.Throwable-">
    Throwable.initCause(Throwable)</a> method. It is going to
    be properly annotated and printed when sent to logger:
<pre>
public void doSomething() throws IOException {
    try {
        doSomethingElse();
    } catch (IllegalArgumentException iae) {
        IOException ioe = new IOException("did not work: " + iae);
        ioe.initCause(iae);
        throw ioe;
    }
}
// ...
try {
    foo.doSomething();
} catch (IOException ioe) {
    logger.log(Level.WARNING, null, ioe);
}
</pre>

<h5>Logging a warning and debug messages</h5>

<p>
Logging shall usually be done with a named loggers, as that allows
proper turning on and off from the command line. To log something
into the log file one should use Level.INFO or higher:
</p>

<pre>
private static final Logger LOG =
    Logger.getLogger("org.netbeans.modules.foo");
    
public void doSomething(String arg) {
    if (arg.length() == 0) {
        LOG.warning("doSomething called on empty string");
        return;
    }
    // ...
}
</pre>
<p>
For writing debugging messages it is also better to have a named logger,
but the important difference is to use <code>Level.FINE</code> and lower
severity levels:
</p>
<pre>
package org.netbeans.modules.foo;
class FooModule {
    public static final Logger LOG =
        Logger.getLogger("org.netbeans.modules.foo");
}
// ...
class Something {
    public void doSomething(String arg) {
        FooModule.LOG.log(Level.FINER, "Called doSomething with arg {0}", arg);
    }
}
</pre>

<p>

<h5>Annotate Exceptions</h5>

<p>
There is an easy way how to annotate exceptions with localized and non-localized
messages in NetBeans. One can use
<a href="@org-openide-util@/org/openide/util/Exceptions.html#attachMessage-E-java.lang.String-">
    Exceptions.attachMessage
</a> or 
<a href="@org-openide-util@/org/openide/util/Exceptions.html#attachLocalizedMessage-E-java.lang.String-">
    Exceptions.attachLocalizedMessage
</a>. The non-localized messages are guaranteed to be printed when one does
<code>ex.printStackTrace()</code>, to extract associated localized message
one can use 
<a href="@org-openide-util@/org/openide/util/Exceptions.html#findLocalizedMessage-java.lang.Throwable-">
    Exceptions.findLocalizedMessage
</a>.
</p>


<a name="structured"><h3>Using Structured Logging for Communication</h3></a>

<p>
In spite of what one might think the JDK logging API is not just about 
sending textual messages to log files, but it can also be used as a 
communication channel between two pieces of the application that need
to exchange structured data. What is even more interesting is that
this kind of extended usage can coexist very well with the plain old
good writing of messages to log files. This is all possible due to
a very nice design of the single <q>logging record</q> - the
<a href="@JDK@/java/util/logging/LogRecord.html">LogRecord</a>. 
</p>


<p>
Well written structured logging shall use the <q>localized</q> message
approach and thus assign to all its 
<a href="@JDK@/java/util/logging/LogRecord.html">LogRecord</a>s 
a <a href="@JDK@/java/util/ResourceBundle.html">ResourceBundle</a> and
use just a key to the bundle as the actually logged message. 
This is a good idea anyway, as it speeds up logging, because if the message is not
going to be needed, the final string is not concatenated at all.
However this would not be very powerful logging, so
another important thing is to provide parameters to the 
<a href="@JDK@/java/util/logging/LogRecord.html">LogRecord</a> via
its <code>setParameters</code> method. This, in combination with the
<a href="@JDK@/java/text/MessageFormat.html">MessageFormat</a> used when 
the final logger is composing the logged message, further delay's 
the concatenations of strings. Morevoer it allows the advanced communication
described above - e.g. there can be another module consumming the message
which can directly get access to live objects and processes them in any way. 
</p>

<p>
Here is an example of the program that uses such structured logging:
</p>

<pre>
public static void main(String[] args) {
    ResourceBundle rb = ResourceBundle.getBundle("your.package.Log");

    int sum = 0;
    for (int i = 0; i < 10; i++) {        
        LogRecord r = new LogRecord(Level.INFO, "MSG_Add");
        r.setResourceBundle(rb);
        r.setParameters(new Object[] { sum, i });
        Logger.global.log(r);
        sum += i;
    }        

    LogRecord r = new LogRecord(Level.INFO, "MSG_Result");
    r.setResourceBundle(rb);
    r.setParameters(new Object[] { sum });
    Logger.global.log(r);
}    
</pre>
<p>
Of course the two keys has to be reasonably defined in the <code>Log.properties</code>
bundle:
</p>
<pre>
# {0} - current sum
# {1} - add
MSG_Add=Going to add {1} to {0}


# {0} - final sum
MSG_Result=The sum is {0}
</pre>
<p>
When executed with logging on, this example is going to print the expected
output with the right messages and well substituted values:
</p>
<pre>
INFO: Going to add 0 to 0
INFO: Going to add 1 to 0
INFO: Going to add 2 to 1
INFO: Going to add 3 to 3
INFO: Going to add 4 to 6
INFO: Going to add 5 to 10
INFO: Going to add 6 to 15
INFO: Going to add 7 to 21
INFO: Going to add 8 to 28
INFO: Going to add 9 to 36
INFO: The sum is 45    
</pre>
<p>
This not surprising behaviour, still however it is one of the most efficient
because the text <code>Going to add X to Y</code> is not constructed by the
code itself, but by the logger, and only if really needed. So the descrbied 
logging style is useful of its own, however the
interesting part is that one can now write following code and intercept behaviour
of one independent part of code from another one:
</p>

<pre>
public class Test extends Handler {
    private int add;
    private int sum;
    private int allAdd;
    
    public void publish(LogRecord record) {
        if ("MSG_Add".equals(record.getMessage())) {
            add++;
            allAdd += ((Integer)record.getParameters()[1]).intValue();
        }
        if ("MSG_Result".equals(record.getMessage())) {
            sum++;
        }
    }
    public void flush() {
        Logger.global.info("There was " + add + " of adds and " + sum + " of sum outputs, all adding: " + allAdd);
    }
    public void close() { flush(); }       
    
    static {
        Logger.global.addHandler(new Test());
    }
}   
</pre>
<p>
The basic trick is to register own 
<a href="@JDK@/java/util/logging/Handler.html">Handler</a>
and thus get access to provided 
<a href="@JDK@/java/util/logging/LogRecord.html">LogRecord</a>s
and process them in any custom way, possibly pretty different than just
printing the strings to log files. Of course, this is only 
possible because the handler understand the generic names of logged messages - 
e.g. <code>MSG_Add</code> and <code>MSG_Result</code> and knows the format of their 
arguments, it can do the analysis, and output:
</p>
<pre>INFO: There was 10 of adds and 1 of sum outputs, all adding: 45</pre>
<p>
Indeed a structural logging can achive much more than shown in this
simplistic example. Moreover it seems to
be one of the most effective ways for logging, so it is highly recommended
to use it where possible.
</p>

<!--
These are the base patterns to be used when logging from inside of NetBeans.
A care has been taken to mimic as closely as possible the way logging is
done in any other system and as a result it should be pretty easy to smoothly
incorporate any 3rd party library into NetBeans that is using JDK's logging
or a wrapper around it.

<!-- Should there be more questions to ask, feel free to
consult the documentation that has been
<a href="http://openide.netbeans.org/tutorial/reviews/opinions_35067.html">created during the development</a>
and implementation of the logging functionality in NetBeans.
-->

</p>
  
  </body>
</html>
